bitkeeper revision 1.1273.1.1 (4252c7d35i_j5GPb1ONx5tb9t7WG4g)

Revamp xentrace. Clean up Xen scheduler tracings.

Signed-off-by: bin.ren@cl.cam.ac.uk

diff --git a/tools/xentrace/formats b/tools/xentrace/formats
index 0452385484fc500271684f024a167e51ce367c94..bdec34fa6456ea1b5e79d4b657f0caddd038f845 100644 (file)
--- a/tools/xentrace/formats
+++ b/tools/xentrace/formats
@@ -1,35 +1,34 @@
-0x00010000     CPU%(cpu)d %(tsc).6f sched_add_domain(0x%(3)08x)            [ dom id = 0x%(2)08x   ]
-0x00010001     CPU%(cpu)d %(tsc).6f sched_rem_domain(0x%08(3)x)            [ dom id = 0x%(2)08x   ]
-0x00010002     CPU%(cpu)d %(tsc).6f __wake_up(0x%(3)08x)                   [ dom id = 0x%(2)08x   ]
-0x00010003     CPU%(cpu)d %(tsc).6f do_block()                             [ current = 0x%(2)08x  ]
-0x00010004     CPU%(cpu)d %(tsc).6f do_yield()                             [ current = %(2)08x    ]
-0x00010005     CPU%(cpu)d %(tsc).6f do_set_timer_op(0x%(4)08x, 0x%(5)08x)  [ current = 0x%(3)08x  ]
-0x00010006     CPU%(cpu)d %(tsc).6f sched_ctl(0x%(1)08x)
-0x00010007     CPU%(cpu)d %(tsc).6f sched_adjdom(params)                   [ dom id = 0x%(2)08x   ]
-0x00010008     CPU%(cpu)d %(tsc).6f __reschedule(0x%(3)08x)                [ dom id = 0x(2)08x    ]
-0x00010009     CPU%(cpu)d %(tsc).6f switching to task_struct 0x%(1)08x     [ dom id = 0x%(1)x     ]
-0x0001000A     CPU%(cpu)d %(tsc).6f s_timer_fn(unused)
-0x0001000B     CPU%(cpu)d %(tsc).6f t_timer_fn(unused)
-0x0001000C     CPU%(cpu)d %(tsc).6f dom_timer_fn(data)
-0x0001000D     CPU%(cpu)d %(tsc).6f fallback_timer_fn(unused)
+0x00010000     CPU%(cpu)d      %(tsc)d         sched_add_domain        [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010001     CPU%(cpu)d      %(tsc)d         sched_rem_domain        [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010002     CPU%(cpu)d      %(tsc)d         domain_sleep            [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010003     CPU%(cpu)d      %(tsc)d         domain_wake             [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010004     CPU%(cpu)d      %(tsc)d         do_yield                [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010005     CPU%(cpu)d      %(tsc)d         do_block                [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010006     CPU%(cpu)d      %(tsc)d         domain_shutdown         [ domid = 0x%(1)08x, edomid = 0x%(2)08x, reason = 0x%(3)08x ]
+0x00010007     CPU%(cpu)d      %(tsc)d         sched_ctl
+0x00010008     CPU%(cpu)d      %(tsc)d         sched_adjdom            [ domid = 0x%(1)08x ]
+0x00010009     CPU%(cpu)d      %(tsc)d         __enter_scheduler       [ prev<domid:edomid> = 0x%(1)08x : 0x%(2)08x, next<domid:edomid> = 0x%(3)08x : 0x%(4)08x ]
+0x0001000A     CPU%(cpu)d      %(tsc)d         s_timer_fn
+0x0001000B     CPU%(cpu)d      %(tsc)d         t_timer_fn
+0x0001000C     CPU%(cpu)d      %(tsc)d         dom_timer_fn
 
 
-0x00020008     CPU%(cpu)d %(tsc).6f enter: dom0_create_dom ( )
-0x00030008     CPU%(cpu)d %(tsc).6f leave: dom0_create_dom ( )
+0x00020008     CPU%(cpu)d      %(tsc)d         enter: dom0_create_dom
+0x00030008     CPU%(cpu)d      %(tsc)d         leave: dom0_create_dom
+0x00020009     CPU%(cpu)d      %(tsc)d         enter: dom0_destroy_dom
+0x00030009     CPU%(cpu)d      %(tsc)d         leave: dom0_destroy_dom
+0x0002000A     CPU%(cpu)d      %(tsc)d         enter: dom0_start_dom
+0x0003000A     CPU%(cpu)d      %(tsc)d         leave: dom0_start_dom
+0x0002000B     CPU%(cpu)d      %(tsc)d         enter: dom0_stop_dom
+0x0003000B     CPU%(cpu)d      %(tsc)d         leave: dom0_stop_dom
+0x0002000C     CPU%(cpu)d      %(tsc)d         enter: dom0_getinfo
+0x0003000C     CPU%(cpu)d      %(tsc)d         leave: dom0_getinfo
+0x0002000D     CPU%(cpu)d      %(tsc)d         enter: dom0_build
+0x0003000D     CPU%(cpu)d      %(tsc)d         leave: dom0_build
+0x00020019     CPU%(cpu)d      %(tsc)d         enter: dom0_shadow_op
+0x00030019     CPU%(cpu)d      %(tsc)d         leave: dom0_shadow_op
 
-0x00020009     CPU%(cpu)d %(tsc).6f enter: dom0_destroy_dom ( dom=0x%(2)x )
-0x00030009     CPU%(cpu)d %(tsc).6f leave: dom0_destroy_dom ( dom=0x%(2)x ) = %(1)d
 
-0x0002000A     CPU%(cpu)d %(tsc).6f enter: dom0_start_dom ( dom=0x%(2)x )
-0x0003000A     CPU%(cpu)d %(tsc).6f leave: dom0_start_dom ( dom=0x%(2)x ) = %(1)d
-0x0002000B     CPU%(cpu)d %(tsc).6f enter: dom0_stop_dom ( dom=0x%(2)x )
-0x0003000B     CPU%(cpu)d %(tsc).6f leave: dom0_stop_dom ( dom=0x%(2)x ) = %(1)d
-0x0002000C     CPU%(cpu)d %(tsc).6f enter: dom0_getinfo ( dom=0x%(2)x )
-0x0003000C     CPU%(cpu)d %(tsc).6f leave: dom0_getinfo ( dom=0x%(2)x ) = %(1)d
-0x0002000D     CPU%(cpu)d %(tsc).6f enter: dom0_build ( dom=0x%(2)x )
-0x0003000D     CPU%(cpu)d %(tsc).6f leave: dom0_build ( dom=0x%(2)x ) = %(1)d
-
-0x00020019     CPU%(cpu)d %(tsc).6f enter: dom0_shadow_op ( dom=0x%(2)x, %(3)d )
-0x00030019     CPU%(cpu)d %(tsc).6f leave: dom0_shadow_op ( dom=0x%(2)x, %(3)d  ) = %(1)d
-
-#0x0           CPU%(cpu)d %(tsc).6f %(event)x
+0x00040001     CPU%(cpu)d      %(tsc)d         VMX_VMEXIT              [ domid = 0x%(1)08x, eip = 0x%(2)08x, reason = 0x%(3)08x ]
+0x00040002     CPU%(cpu)d      %(tsc)d         VMX_VECTOR              [ domid = 0x%(1)08x, eip = 0x%(2)08x, vector = 0x%(3)08x ]
+0x00040003     CPU%(cpu)d      %(tsc)d         VMX_INT                 [ domid = 0x%(1)08x, trap = 0x%(2)08x, va = 0x%(3)08x ]
\ No newline at end of file

diff --git a/tools/xentrace/xentrace_format b/tools/xentrace/xentrace_format
index d2e51265d498327f064d97a085d6cc778e8dc789..82b406afe68e7553695cb613f1ce5d81b76f47d5 100644 (file)
--- a/tools/xentrace/xentrace_format
+++ b/tools/xentrace/xentrace_format
@@ -75,8 +75,6 @@ try:
 except getopt.GetoptError:
     usage()
 
-print mhz
-
 signal.signal(signal.SIGTERM, sighand)
 signal.signal(signal.SIGHUP,  sighand)
 signal.signal(signal.SIGINT,  sighand)
@@ -85,8 +83,6 @@ interrupted = 0
 
 defs = read_defs(arg[0])
 
-print defs
-
 # structure of trace record + prepended CPU id (as output by xentrace):
 # CPU(I) TSC(Q) EVENT(L) D1(L) D2(L) D3(L) D4(L) D5(L)
 TRCREC = "IQLLLLLL"

diff --git a/xen/common/dom0_ops.c b/xen/common/dom0_ops.c
index 0c6bb484e0b6e28d1784f53bbbad7d7c474104e9..456066e8aa2d740735b3263e70606e572f7787d3 100644 (file)
--- a/xen/common/dom0_ops.c
+++ b/xen/common/dom0_ops.c
@@ -105,10 +105,6 @@ long do_dom0_op(dom0_op_t *u_dom0_op)
     if ( op->interface_version != DOM0_INTERFACE_VERSION )
         return -EACCES;
 
-    TRACE_5D(TRC_DOM0OP_ENTER_BASE + op->cmd, 
-             0, op->u.dummy[0], op->u.dummy[1], 
-             op->u.dummy[2], op->u.dummy[3] );
-
     switch ( op->cmd )
     {
 
@@ -472,10 +468,6 @@ long do_dom0_op(dom0_op_t *u_dom0_op)
 
     }
 
-    TRACE_5D(TRC_DOM0OP_LEAVE_BASE + op->cmd, ret,
-             op->u.dummy[0], op->u.dummy[1], op->u.dummy[2], op->u.dummy[3]);
-
-
     return ret;
 }
 

diff --git a/xen/common/schedule.c b/xen/common/schedule.c
index 2d6c6bc0ab9606e28b602b1fee2386c3a50d73fe..b905c747d5343f5d117bf54c97cb3c7afa6778b8 100644 (file)
--- a/xen/common/schedule.c
+++ b/xen/common/schedule.c
@@ -48,13 +48,13 @@ string_param("sched", opt_sched);
  */
 #define TRC_SCHED_DOM_ADD             0x00010000
 #define TRC_SCHED_DOM_REM             0x00010001
-#define TRC_SCHED_WAKE                0x00010002
-#define TRC_SCHED_BLOCK               0x00010003
+#define TRC_SCHED_SLEEP               0x00010002
+#define TRC_SCHED_WAKE                0x00010003
 #define TRC_SCHED_YIELD               0x00010004
-#define TRC_SCHED_SET_TIMER           0x00010005
-#define TRC_SCHED_CTL                 0x00010006
-#define TRC_SCHED_ADJDOM              0x00010007
-#define TRC_SCHED_RESCHED             0x00010008
+#define TRC_SCHED_BLOCK               0x00010005
+#define TRC_SCHED_SHUTDOWN            0x00010006
+#define TRC_SCHED_CTL                 0x00010007
+#define TRC_SCHED_ADJDOM              0x00010008
 #define TRC_SCHED_SWITCH              0x00010009
 #define TRC_SCHED_S_TIMER_FN          0x0001000A
 #define TRC_SCHED_T_TIMER_FN          0x0001000B
@@ -186,15 +186,14 @@ void sched_add_domain(struct exec_domain *ed)
     }
 
     SCHED_OP(add_task, ed);
-
-    TRACE_2D(TRC_SCHED_DOM_ADD, d->id, ed);
+    TRACE_2D(TRC_SCHED_DOM_ADD, d->id, ed->eid);
 }
 
 void sched_rem_domain(struct exec_domain *ed) 
 {
     rem_ac_timer(&ed->timer);
     SCHED_OP(rem_task, ed);
-    TRACE_3D(TRC_SCHED_DOM_REM, ed->domain->id, ed->eid, ed);
+    TRACE_2D(TRC_SCHED_DOM_REM, ed->domain->id, ed->eid);
 }
 
 void init_idle_task(void)
@@ -203,19 +202,19 @@ void init_idle_task(void)
         BUG();
 }
 
-void domain_sleep(struct exec_domain *d)
+void domain_sleep(struct exec_domain *ed)
 {
     unsigned long flags;
 
-    spin_lock_irqsave(&schedule_data[d->processor].schedule_lock, flags);
-
-    if ( likely(!domain_runnable(d)) )
-        SCHED_OP(sleep, d);
+    spin_lock_irqsave(&schedule_data[ed->processor].schedule_lock, flags);
+    if ( likely(!domain_runnable(ed)) )
+        SCHED_OP(sleep, ed);
+    spin_unlock_irqrestore(&schedule_data[ed->processor].schedule_lock, flags);
 
-    spin_unlock_irqrestore(&schedule_data[d->processor].schedule_lock, flags);
+    TRACE_2D(TRC_SCHED_SLEEP, ed->domain->id, ed->eid);
  
     /* Synchronous. */
-    while ( test_bit(EDF_RUNNING, &d->ed_flags) && !domain_runnable(d) )
+    while ( test_bit(EDF_RUNNING, &ed->ed_flags) && !domain_runnable(ed) )
         cpu_relax();
 }
 
@@ -224,19 +223,17 @@ void domain_wake(struct exec_domain *ed)
     unsigned long flags;
 
     spin_lock_irqsave(&schedule_data[ed->processor].schedule_lock, flags);
-
     if ( likely(domain_runnable(ed)) )
     {
-        TRACE_2D(TRC_SCHED_WAKE, ed->domain->id, ed);
         SCHED_OP(wake, ed);
 #ifdef WAKE_HISTO
         ed->wokenup = NOW();
 #endif
     }
-    
     clear_bit(EDF_MIGRATED, &ed->ed_flags);
-    
     spin_unlock_irqrestore(&schedule_data[ed->processor].schedule_lock, flags);
+
+    TRACE_2D(TRC_SCHED_WAKE, ed->domain->id, ed->eid);
 }
 
 /* Block the currently-executing domain until a pertinent event occurs. */
@@ -244,8 +241,6 @@ long do_block(void)
 {
     struct exec_domain *ed = current;
 
-    TRACE_2D(TRC_SCHED_BLOCK, ed->domain->id, ed);
-
     ed->vcpu_info->evtchn_upcall_mask = 0;
     set_bit(EDF_BLOCKED, &ed->ed_flags);
 
@@ -253,7 +248,10 @@ long do_block(void)
     if ( event_pending(ed) )
         clear_bit(EDF_BLOCKED, &ed->ed_flags);
     else
+    {
+        TRACE_2D(TRC_SCHED_BLOCK, ed->domain->id, ed->eid);
         __enter_scheduler();
+    }
 
     return 0;
 }
@@ -261,7 +259,7 @@ long do_block(void)
 /* Voluntarily yield the processor for this allocation. */
 static long do_yield(void)
 {
-    TRACE_2D(TRC_SCHED_YIELD, current->domain->id, current);
+    TRACE_2D(TRC_SCHED_YIELD, current->domain->id, current->eid);
     __enter_scheduler();
     return 0;
 }
@@ -290,6 +288,8 @@ long do_sched_op(unsigned long op)
 
     case SCHEDOP_shutdown:
     {
+        TRACE_3D(TRC_SCHED_SHUTDOWN, current->domain->id, current->eid,
+                 (op >> SCHEDOP_reasonshift));
         domain_shutdown((u8)(op >> SCHEDOP_reasonshift));
         break;
     }
@@ -322,12 +322,12 @@ int sched_id()
 
 long sched_ctl(struct sched_ctl_cmd *cmd)
 {
-    TRACE_0D(TRC_SCHED_CTL);
-
     if ( cmd->sched_id != ops.sched_id )
         return -EINVAL;
 
-    return SCHED_OP(control, cmd);
+    SCHED_OP(control, cmd);
+    TRACE_0D(TRC_SCHED_CTL);
+    return 0;
 }
 
 
@@ -346,12 +346,11 @@ long sched_adjdom(struct sched_adjdom_cmd *cmd)
     if ( d == NULL )
         return -ESRCH;
 
-    TRACE_1D(TRC_SCHED_ADJDOM, d->id);
-
     spin_lock_irq(&schedule_data[d->exec_domain[0]->processor].schedule_lock);
     SCHED_OP(adjdom, d, cmd);
     spin_unlock_irq(&schedule_data[d->exec_domain[0]->processor].schedule_lock);
 
+    TRACE_1D(TRC_SCHED_ADJDOM, d->id);
     put_domain(d);
     return 0;
 }
@@ -423,8 +422,6 @@ static void __enter_scheduler(void)
     }
 #endif
 
-    TRACE_2D(TRC_SCHED_SWITCH, next->domain->id, next);
-
     prev->sleep_tick = schedule_data[cpu].tick;
 
     /* Ensure that the domain has an up-to-date time base. */
@@ -435,6 +432,10 @@ static void __enter_scheduler(void)
             send_guest_virq(next, VIRQ_TIMER);
     }
 
+    TRACE_4D(TRC_SCHED_SWITCH,
+             prev->domain->id, prev->eid,
+             next->domain->id, next->eid);
+
     context_switch(prev, next);
 }
 
@@ -456,7 +457,6 @@ int idle_cpu(int cpu)
 /* The scheduler timer: force a run through the scheduler */
 static void s_timer_fn(unsigned long unused)
 {
-    TRACE_0D(TRC_SCHED_S_TIMER_FN);
     raise_softirq(SCHEDULE_SOFTIRQ);
     perfc_incrc(sched_irq);
 }
@@ -467,8 +467,6 @@ static void t_timer_fn(unsigned long unused)
     struct exec_domain *ed  = current;
     unsigned int        cpu = ed->processor;
 
-    TRACE_0D(TRC_SCHED_T_TIMER_FN);
-
     schedule_data[cpu].tick++;
 
     if ( !is_idle_task(ed->domain) )
@@ -488,8 +486,6 @@ static void dom_timer_fn(unsigned long data)
 {
     struct exec_domain *ed = (struct exec_domain *)data;
 
-    TRACE_0D(TRC_SCHED_DOM_TIMER_FN);
-    
     update_dom_time(ed);
     send_guest_virq(ed, VIRQ_TIMER);
 }

diff --git a/xen/include/public/dom0_ops.h b/xen/include/public/dom0_ops.h
index cf359f00e935e5011326712adfb0d456d33678ee..b7836ea2feac4882849292512d0d0ac434bb85d9 100644 (file)
--- a/xen/include/public/dom0_ops.h
+++ b/xen/include/public/dom0_ops.h
@@ -371,19 +371,19 @@ typedef struct {
         dom0_setdomaininfo_t     setdomaininfo;
         dom0_getdomaininfo_t     getdomaininfo;
         dom0_getpageframeinfo_t  getpageframeinfo;
-       dom0_msr_t               msr;
-       dom0_debug_t             debug;
-       dom0_settime_t           settime;
-       dom0_readconsole_t       readconsole;
-       dom0_pincpudomain_t      pincpudomain;
+        dom0_msr_t               msr;
+        dom0_debug_t             debug;
+        dom0_settime_t           settime;
+        dom0_readconsole_t      readconsole;
+        dom0_pincpudomain_t      pincpudomain;
         dom0_gettbufs_t          gettbufs;
         dom0_physinfo_t          physinfo;
         dom0_pcidev_access_t     pcidev_access;
         dom0_sched_id_t          sched_id;
-       dom0_shadow_control_t    shadow_control;
-       dom0_setdomaininitialmem_t setdomaininitialmem;
-       dom0_setdomainmaxmem_t   setdomainmaxmem;
-       dom0_getpageframeinfo2_t getpageframeinfo2;
+        dom0_shadow_control_t    shadow_control;
+        dom0_setdomaininitialmem_t setdomaininitialmem;
+        dom0_setdomainmaxmem_t   setdomainmaxmem;
+        dom0_getpageframeinfo2_t getpageframeinfo2;
         dom0_add_memtype_t       add_memtype;
         dom0_del_memtype_t       del_memtype;
         dom0_read_memtype_t      read_memtype;